[INFO] fetching crate wl-proxy 0.1.2...
[INFO] testing wl-proxy-0.1.2 against try#0abe69e6c16114311cc2700e972492e64d69c28f for pr-154065-1
[INFO] extracting crate wl-proxy 0.1.2 into /workspace/builds/worker-1-tc2/source
[INFO] started tweaking crates.io crate wl-proxy 0.1.2
[INFO] finished tweaking crates.io crate wl-proxy 0.1.2
[INFO] tweaked toml for crates.io crate wl-proxy 0.1.2 written to /workspace/builds/worker-1-tc2/source/Cargo.toml
[INFO] validating manifest of crates.io crate wl-proxy 0.1.2 on toolchain 0abe69e6c16114311cc2700e972492e64d69c28f
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--manifest-path" "Cargo.toml" "--no-deps", kill_on_drop: false }`
[INFO] crate crates.io crate wl-proxy 0.1.2 already has a lockfile, it will not be regenerated
[INFO] running `Command { std: CARGO_HOME="/workspace/cargo-home" RUSTUP_HOME="/workspace/rustup-home" "/workspace/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "fetch" "--manifest-path" "Cargo.toml", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "metadata" "--no-deps" "--format-version=1", kill_on_drop: false }`
[INFO] [stdout] 216843dc2058c64268a295097e5c59d54912ef6208d0e43747bd08e2192b972e
[INFO] running `Command { std: "docker" "start" "-a" "216843dc2058c64268a295097e5c59d54912ef6208d0e43747bd08e2192b972e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "inspect" "216843dc2058c64268a295097e5c59d54912ef6208d0e43747bd08e2192b972e", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "216843dc2058c64268a295097e5c59d54912ef6208d0e43747bd08e2192b972e", kill_on_drop: false }`
[INFO] [stdout] 216843dc2058c64268a295097e5c59d54912ef6208d0e43747bd08e2192b972e
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "build" "--frozen" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] 15b454985b6f96db22592a2836148b6fa5436498db96a34bd79d8bf2313cb296
[INFO] running `Command { std: "docker" "start" "-a" "15b454985b6f96db22592a2836148b6fa5436498db96a34bd79d8bf2313cb296", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling phf_shared v0.13.1
[INFO] [stderr]    Compiling syn v2.0.111
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling syn v1.0.109
[INFO] [stderr]    Compiling linearize v0.1.5
[INFO] [stderr]    Compiling thiserror v2.0.17
[INFO] [stderr]    Compiling parking_lot_core v0.9.12
[INFO] [stderr]    Compiling phf_generator v0.13.1
[INFO] [stderr]    Compiling run-on-drop v1.0.0
[INFO] [stderr]    Compiling parking_lot v0.12.5
[INFO] [stderr]    Compiling isnt v0.2.0
[INFO] [stderr]    Compiling debug-fn v1.0.0
[INFO] [stderr]    Compiling error_reporter v1.0.0
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling linearize-derive v0.2.1
[INFO] [stderr]    Compiling thiserror-impl v2.0.17
[INFO] [stderr]    Compiling phf_macros v0.13.1
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling phf v0.13.1
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `dev` profile [unoptimized + debuginfo] target(s) in 17.62s
[INFO] running `Command { std: "docker" "inspect" "15b454985b6f96db22592a2836148b6fa5436498db96a34bd79d8bf2313cb296", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "15b454985b6f96db22592a2836148b6fa5436498db96a34bd79d8bf2313cb296", kill_on_drop: false }`
[INFO] [stdout] 15b454985b6f96db22592a2836148b6fa5436498db96a34bd79d8bf2313cb296
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen" "--no-run" "--message-format=json", kill_on_drop: false }`
[INFO] [stdout] a8de46b3c696d7754e1014639f25a2de0ebd8419bd469a21bd9c22d05d87449a
[INFO] running `Command { std: "docker" "start" "-a" "a8de46b3c696d7754e1014639f25a2de0ebd8419bd469a21bd9c22d05d87449a", kill_on_drop: false }`
[INFO] [stderr]    Compiling regex-syntax v0.8.8
[INFO] [stderr]    Compiling anstream v0.6.21
[INFO] [stderr]    Compiling jiff v0.2.16
[INFO] [stderr]    Compiling regex-automata v0.4.13
[INFO] [stderr]    Compiling regex v1.12.2
[INFO] [stderr]    Compiling uapi-proc v0.0.5
[INFO] [stderr]    Compiling uapi v0.2.13
[INFO] [stderr]    Compiling env_filter v0.1.4
[INFO] [stderr]    Compiling env_logger v0.11.8
[INFO] [stderr]    Compiling wl-proxy v0.1.2 (/opt/rustwide/workdir)
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 24.15s
[INFO] running `Command { std: "docker" "inspect" "a8de46b3c696d7754e1014639f25a2de0ebd8419bd469a21bd9c22d05d87449a", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "a8de46b3c696d7754e1014639f25a2de0ebd8419bd469a21bd9c22d05d87449a", kill_on_drop: false }`
[INFO] [stdout] a8de46b3c696d7754e1014639f25a2de0ebd8419bd469a21bd9c22d05d87449a
[INFO] running `Command { std: "docker" "create" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/target:/opt/rustwide/target:rw,Z" "-v" "/var/lib/crater-agent-workspace/builds/worker-1-tc2/source:/opt/rustwide/workdir:ro,Z" "-v" "/var/lib/crater-agent-workspace/cargo-home:/opt/rustwide/cargo-home:ro,Z" "-v" "/var/lib/crater-agent-workspace/rustup-home:/opt/rustwide/rustup-home:ro,Z" "-e" "SOURCE_DIR=/opt/rustwide/workdir" "-e" "CARGO_TARGET_DIR=/opt/rustwide/target" "-e" "CARGO_INCREMENTAL=0" "-e" "RUST_BACKTRACE=full" "-e" "RUSTFLAGS=--cap-lints=forbid" "-e" "RUSTDOCFLAGS=--cap-lints=forbid" "-e" "CARGO_HOME=/opt/rustwide/cargo-home" "-e" "RUSTUP_HOME=/opt/rustwide/rustup-home" "-w" "/opt/rustwide/workdir" "-m" "1610612736" "--user" "0:0" "--network" "none" "ghcr.io/rust-lang/crates-build-env/linux@sha256:d429b63d4308055ea97f60fb1d3dfca48854a00942f1bd2ad806beaf015945ec" "/opt/rustwide/cargo-home/bin/cargo" "+0abe69e6c16114311cc2700e972492e64d69c28f" "test" "--frozen", kill_on_drop: false }`
[INFO] [stdout] bce7c03ef4aec8bb858e756ed0a6d4abee44eed34644fc4243328a5c8e506ea1
[INFO] running `Command { std: "docker" "start" "-a" "bce7c03ef4aec8bb858e756ed0a6d4abee44eed34644fc4243328a5c8e506ea1", kill_on_drop: false }`
[INFO] [stderr]     Finished `test` profile [unoptimized + debuginfo] target(s) in 0.07s
[INFO] [stderr]      Running unittests src/lib.rs (/opt/rustwide/target/debug/deps/wl_proxy-c279e5984628a866)
[INFO] [stdout] 
[INFO] [stdout] running 111 tests
[INFO] [stderr] [1926174.133] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.272] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.328] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.343] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.356] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.372] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.395] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.65535 message: unknown message id 65535
[INFO] [stderr] [1926176.830] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.853] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.877] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.888] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926176.898] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.909] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926176.928] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926176.935] {client} server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1926176.941] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926176.961] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926176.971] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926176.975] {proxy } client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1926176.981] {proxy } server      <= wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1926176.985] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926176.990] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926177.208] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.225] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.249] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.260] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.271] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.282] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.304] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [1926177.580] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.595] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.625] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.636] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.646] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.657] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.680] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.687] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.717] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.730] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.741] {server} client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926177.752] {server} client#2    -> wlproxy_test#3.echo_object(echo: wlproxy_test_object_echo#5, object: unknown#4)
[INFO] [stderr] [1926177.759] {server} client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1926177.779] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926177.786] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926177.792] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926177.796] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926177.855] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.870] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.891] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.897] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.909] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.919] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926177.940] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926177.946] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.018] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.037] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.050] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.065] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.072] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.078] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.110] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.119] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926178.120] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.135] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.136] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.146] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926178.157] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926178.162] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#5)
[INFO] [stderr] [1926178.182] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926178.356] {proxy } server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1926178.362] {proxy } client#2    <= wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1926178.377] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926178.382] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926178.389] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926178.391] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926178.395] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926178.400] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926178.422] {client} server      -> wlproxy_test_object_echo#5.object(obj: unknown#4)
[INFO] [stderr] [1926178.427] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926178.431] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926178.434] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stdout] test endpoint::tests::invalid_message ... ok
[INFO] [stdout] test endpoint::tests::test ... ok
[INFO] [stdout] test fixed::tests::debug ... ok
[INFO] [stdout] test fixed::tests::from_f32 ... ok
[INFO] [stdout] test fixed::tests::from_i32 ... ok
[INFO] [stdout] test fixed::tests::from_i64 ... ok
[INFO] [stdout] test fixed::tests::from_ints ... ok
[INFO] [stdout] test client::tests::disconnected ... ok
[INFO] [stdout] test endpoint::tests::dispatch_destroyed ... ok
[INFO] [stdout] test client::tests::unset_handler ... ok
[INFO] [stdout] test endpoint::tests::lookup ... ok
[INFO] [stdout] test client::tests::objects ... ok
[INFO] [stdout] test fixed::tests::minima ... ok
[INFO] [stdout] test fixed::tests::display ... ok
[INFO] [stdout] test fixed::tests::test_binops ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Could not add synthetic global: the message handler is already borrowed
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Could not handle client bind: the message handler is already borrowed
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Could not handle server global: the message handler is already borrowed
[INFO] [stdout] test fixed::tests::test_shiftops ... ok
[INFO] [stdout] test fixed::tests::test_unops ... ok
[INFO] [stdout] test fixed::tests::to_f32 ... ok
[INFO] [stdout] test fixed::tests::to_i32_floor ... ok
[INFO] [stdout] test fixed::tests::to_i32_nearest ... ok
[INFO] [stdout] test fixed::tests::to_i32_zero ... ok
[INFO] [stdout] test fixed::tests::wire ... ok
[INFO] [stdout] test global_mapper::tests::test_default ... ok
[INFO] [stdout] test global_mapper::tests::test_add_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_bind_synthetic ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Could not handle server global remove: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_error ... ok
[INFO] [stdout] test fixed::tests::to_i32_ceil ... ok
[INFO] [stdout] test global_mapper::tests::test_ignore_global ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Could not remove synthetic global: the message handler is already borrowed
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_ignored ... ok
[INFO] [stdout] test global_mapper::tests::test_try_add_synthetic_global_error ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stdout] test global_mapper::tests::test ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_error ... ok
[INFO] [stdout] test fixed::tests::one_two ... ok
[INFO] [stdout] test global_mapper::tests::test_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_synthetic ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Client sent wl_registry.bind for name 999 but not such global exists
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::global_mapper] Server sent wl_registry.global_remove for name 999 but no such global exists
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_bind_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_remove_synthetic_global_error ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_nonexistent ... ok
[INFO] [stdout] test global_mapper::tests::test_try_forward_global_remove_ignored ... ok
[INFO] [stdout] test handler::tests::borrow ... ok
[INFO] [stdout] test handler::tests::clone ... ok
[INFO] [stdout] test handler::tests::replace ... ok
[INFO] [stdout] test handler::tests::map ... ok
[INFO] [stderr] [1926197.172] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.186] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.211] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.219] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.225] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.237] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.269] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.281] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.484] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.497] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.523] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.536] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.543] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.595] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.649] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926197.665] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926197.996] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.016] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926198.042] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.051] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.065] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926198.077] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926198.134] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.135] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926198.144] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926198.154] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4294967295)
[INFO] [stderr] [1926198.160] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.167] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926198.174] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926198.185] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::client ... ok
[INFO] [stdout] test object::tests::client_id ... ok
[INFO] [stdout] test object::tests::destroyed_client ... ok
[INFO] [stdout] test object::tests::client_object_with_server_id ... ok
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not handle a wl_display#1.sync message: could not assign client id 4294967295 to argument callback: the id 4294967295 is too large to be a client id
[INFO] [stderr] [1926199.114] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::duplicate_client_id ... ok
[INFO] [stderr] [1926199.136] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.160] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926199.167] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926199.186] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.197] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.213] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926199.218] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926199.235] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926199.243] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926199.246] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926199.251] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926199.267] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926199.276] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.290] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926199.297] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926199.302] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.311] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926199.329] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926199.333] {client} server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926199.350] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926199.360] {proxy } server      <= wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [1926199.363] {proxy } client#2    -> wlproxy_test#3.create_dummy(id: wlproxy_test_dummy#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not handle a wlproxy_test#3.create_dummy message: could not assign client id 4 to argument id: the client id 4 is already in use
[INFO] [stderr] [1926201.125] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test object::tests::double_send ... ok
[INFO] [stderr] [1926201.145] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::duplicate_generated_client_id ... ok
[INFO] [stderr] [1926201.156] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test object::tests::get_handler ... ok
[INFO] [stderr] [1926201.167] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stdout] test object::tests::forward ... ok
[INFO] [stderr] [1926201.178] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test object::tests::server_destroyed ... ok
[INFO] [stderr] [1926201.184] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test object::tests::server_sent ... ok
[INFO] [stderr] [1926201.188] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test object::tests::state ... ok
[INFO] [stderr] [1926201.192] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926201.233] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926201.238] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926201.253] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926201.259] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926201.266] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926201.268] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926201.272] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926201.276] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926201.300] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926201.305] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926201.309] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926201.312] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926201.377] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926201.388] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926201.410] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926201.419] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926201.426] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926201.438] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926201.469] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1926202.110] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.113] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.122] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.122] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.145] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.145] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.153] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.153] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.159] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.163] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.171] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.172] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.200] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926202.221] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926202.231] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926202.261] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.269] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.460] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.471] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.495] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.503] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.509] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.522] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.550] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1926202.555] {client} server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1926202.557] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.560] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.566] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.579] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1926202.589] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1926202.593] {proxy } client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1926202.595] {proxy } server      <= wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1926202.598] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.603] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.631] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#4)
[INFO] [stderr] [1926202.645] {server} client#2    -> wlproxy_test_non_forward#4.echo()
[INFO] [stderr] [1926202.648] {server} client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1926202.655] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.661] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.666] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.717] {proxy } server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1926202.721] {proxy } client#2    <= wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1926202.746] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.749] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.754] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.759] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.784] {client} server      -> wlproxy_test_non_forward#4.echoed()
[INFO] [stderr] [1926202.787] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.791] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.806] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1926202.810] {client} server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1926202.816] {client} server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926202.842] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1926202.851] {proxy } client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1926202.855] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926202.862] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.896] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926202.902] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.907] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.935] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926202.938] {proxy } client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926202.942] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926202.947] {proxy } client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926202.956] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.967] {client} server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926202.966] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926202.970] {client} server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926202.982] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1926202.983] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.986] {client} server      <= wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [1926202.989] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926202.994] {client} server      <= wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1926203.003] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.012] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#6)
[INFO] [stderr] [1926203.015] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.019] {proxy } client#2    -> wlproxy_test_non_forward#6.echo()
[INFO] [stderr] [1926203.044] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926203.063] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926203.073] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z WARN  wl_proxy::protocol_helpers] Could not forward a wlproxy_test_non_forward.echo message: the receiver has no server id
[INFO] [stderr] [1926203.107] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#7)
[INFO] [stderr] [1926203.118] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926203.147] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926203.153] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926203.158] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926203.181] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926203.184] {proxy } client#2    <= wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1926203.188] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926203.193] {proxy } client#2    <= wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1926203.195] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.203] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.211] {client} server      -> wl_callback#7.done(callback_data: 0)
[INFO] [stderr] [1926203.214] {client} server      -> wl_display#1.delete_id(id: 7)
[INFO] [stderr] [1926203.214] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926203.222] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.227] {client} server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1926203.230] {client} server      <= wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1926203.237] {client} server      <= wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1926203.238] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.255] {proxy } client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#7)
[INFO] [stderr] [1926203.262] {proxy } server      <= wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1926203.266] {proxy } client#2    -> wlproxy_test_non_forward#7.echo()
[INFO] [stderr] [1926203.266] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.268] {proxy } server      <= wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1926203.268] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.271] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#8)
[INFO] [stderr] [1926203.272] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.276] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.280] {proxy } server      <= wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926203.294] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1926203.301] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4294967295)
[INFO] [stderr] [1926203.304] {server} client#2    -> wlproxy_test#3.create_non_forward(id: wlproxy_test_non_forward#5)
[INFO] [stderr] [1926203.310] {server} client#2    -> wlproxy_test_non_forward#5.echo()
[INFO] [stderr] [1926203.313] {server} client#2    <= wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1926203.317] {server} client#2    -> wl_display#1.sync(callback: wl_callback#6)
[INFO] [stderr] [1926203.322] {server} client#2    <= wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926203.327] {server} client#2    <= wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926203.353] {proxy } server      -> wlproxy_test_non_forward#5.echoed()
[INFO] [stderr] [1926203.355] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.356] {proxy } client#2    <= wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1926203.360] {proxy } server      -> wl_callback#6.done(callback_data: 0)
[INFO] [stderr] [1926203.363] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.364] {proxy } client#2    <= wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1926203.368] {proxy } server      -> wl_display#1.delete_id(id: 6)
[INFO] [stderr] [1926203.372] {proxy } client#2    <= wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1926203.373] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926203.381] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.392] {client} server      -> wlproxy_test_non_forward#7.echoed()
[INFO] [stderr] [1926203.395] {client} server      -> wl_callback#8.done(callback_data: 0)
[INFO] [stderr] [1926203.397] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.398] {client} server      -> wl_display#1.delete_id(id: 8)
[INFO] [stderr] [1926203.425] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.428] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926203.433] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.437] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926203.455] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#50)
[INFO] [stderr] [1926203.895] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.907] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.929] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.936] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.942] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.953] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926203.973] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926203.980] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926204.443] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926204.455] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926204.478] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926204.485] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926204.491] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926204.502] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926204.521] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926204.528] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926204.546] {client} server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1926204.555] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.572] {proxy } client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1926204.575] {proxy } server      <= wlproxy_test#3.send_object()
[INFO] [stderr] [1926204.579] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.587] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.614] {server} client#2    -> wlproxy_test#3.send_object()
[INFO] [stderr] [1926204.624] {server} client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1926204.634] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.639] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.644] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.668] {proxy } server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1926204.675] {proxy } client#2    <= wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1926204.680] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.682] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.686] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.690] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.707] {client} server      -> wlproxy_test#3.sent_object(echo: wlproxy_test_server_sent#4278190080)
[INFO] [stderr] [1926204.714] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.717] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.726] {client} server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1926204.732] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.747] {proxy } client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1926204.750] {proxy } server      <= wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1926204.753] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.759] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.784] {server} client#2    -> wlproxy_test_server_sent#4278190080.send_destroy()
[INFO] [stderr] [1926204.787] {server} client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1926204.794] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926204.799] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.803] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.829] {proxy } server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1926204.834] {proxy } client#2    <= wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1926204.841] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.843] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.847] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.851] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926204.868] {client} server      -> wlproxy_test_server_sent#4278190080.destroyed()
[INFO] [stderr] [1926204.872] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926204.875] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926205.318] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926205.330] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926205.354] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926205.361] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926205.366] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926205.377] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926205.396] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926205.403] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926206.351] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926206.363] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926206.388] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926206.396] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926206.402] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926206.414] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926206.440] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926206.451] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test object::tests::request_without_server ... ok
[INFO] [stdout] test object::tests::version ... ok
[INFO] [stdout] test poll::tests::edge_trigger ... ok
[INFO] [stdout] test poll::tests::many ... ok
[INFO] [stdout] test poll::tests::test ... ok
[INFO] [stderr] [1926276.039] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926276.241] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926276.284] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926276.294] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926276.303] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926276.319] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926276.522] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926276.538] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test acceptor::tests::test ... FAILED
[INFO] [stdout] test fixed::tests::minimum - should panic ... ok
[INFO] [stdout] test fixed::tests::maximum - should panic ... ok
[INFO] [stderr] [1926301.580] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926301.609] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926301.647] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926301.657] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926301.677] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926301.694] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926301.724] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926301.755] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926301.774] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test object::tests::duplicate_server_id - should panic ... ok
[INFO] [stdout] test object::tests::invalid_server_id - should panic ... ok
[INFO] [stdout] test state::tests::destroyed_readable ... ok
[INFO] [stdout] test state::tests::destructor ... ok
[INFO] [stdout] test state::tests::count_hops ... ok
[INFO] [stdout] test handler::tests::multi_borrow - should panic ... ok
[INFO] [stdout] test state::tests::remote_destructor ... ok
[INFO] [stdout] test state::tests::add_client ... ok
[INFO] [stdout] test state::tests::recursive_dispatch ... ok
[INFO] [stdout] test state::tests::acceptor ... FAILED
[INFO] [stdout] test state::tests::suspend2 ... ok
[INFO] [stderr] [1926304.115] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stdout] test state::tests::suspend1 ... ok
[INFO] [stderr] [1926304.128] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::suspend3 ... ok
[INFO] [stderr] [1926304.140] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stdout] test state::tests::suspend5 ... ok
[INFO] [stderr] [1926304.150] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926304.165] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926304.383] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.395] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.421] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.431] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.437] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.448] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.702] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.714] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.738] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.746] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.752] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.764] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.785] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926304.804] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926304.814] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926304.906] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926304.917] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926304.928] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926304.938] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926304.954] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926305.106] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926305.116] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926305.124] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926305.181] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926305.209] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926305.214] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926305.417] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.419] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.438] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.441] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.463] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.469] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.472] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.480] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.484] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.497] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.502] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.517] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.516] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926305.523] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926305.528] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926305.535] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926305.559] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926305.568] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926305.604] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926305.614] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926305.616] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.620] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1926305.638] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.641] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1926305.650] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926305.657] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1926305.665] {proxy } client#3    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.676] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#4)
[INFO] [stderr] [1926305.677] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1926305.682] {proxy } client#3    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.686] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926305.693] {proxy } server      <= wl_registry#4.bind(name: 0, id: wlproxy_test#5 (version: 1))
[INFO] [stderr] [1926305.695] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1926305.712] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926305.720] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926305.725] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926305.733] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926305.740] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [1926305.745] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [1926305.776] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x78)
[INFO] [stderr] [1926305.796] {proxy } client#3    <= wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [1926305.819] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x79)
[INFO] [stderr] [1926305.826] {proxy } client#3    <= wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [1926305.845] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926305.853] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926305.893] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926305.907] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x78)
[INFO] [stderr] [1926305.911] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x79)
[INFO] [stderr] [1926305.911] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.923] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [1926305.923] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.954] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.956] {proxy } client#3    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x7a)
[INFO] [stderr] [1926305.964] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926305.964] {proxy } client#3    <= wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [1926305.971] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.984] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926305.988] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x7a)
[INFO] [stderr] [1926306.003] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926306.004] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926306.011] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926306.011] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1926306.016] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926306.024] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926306.029] {client} server      -> wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1926306.044] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926306.047] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926306.050] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1926306.056] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926306.056] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926306.061] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1926306.107] {client} server      -> wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1926306.112] {client} server      -> wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1926306.128] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926306.139] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926306.163] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926306.174] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926306.180] {proxy } client#2    <= wlproxy_test_array_echo#5.array(array: 0x62)
[INFO] [stderr] [1926306.187] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#6, array: 0x63)
[INFO] [stderr] [1926306.191] {proxy } client#2    <= wlproxy_test_array_echo#6.array(array: 0x63)
[INFO] [stderr] [1926306.196] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#7, array: 0x64)
[INFO] [stderr] [1926306.204] {proxy } client#2    <= wlproxy_test_array_echo#7.array(array: 0x64)
[INFO] [stderr] [1926306.229] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926306.239] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926306.260] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926306.267] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926306.274] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926306.286] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926306.305] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926306.312] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#5, array: 0x62)
[INFO] [stderr] [1926306.339] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926306.348] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926306.383] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x61)
[INFO] [stderr] [1926306.952] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926306.968] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926306.993] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.001] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.012] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.023] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.039] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.042] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926307.048] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.064] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.069] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x61)
[INFO] [stderr] [1926307.071] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.076] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.106] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.129] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1926307.137] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.148] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.153] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1926307.156] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.164] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1926307.169] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.175] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.178] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.191] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.200] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0)
[INFO] [stderr] [1926307.206] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.211] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1926307.213] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.216] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.224] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.225] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.230] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.231] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.237] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.241] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.241] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.259] {proxy } client#2    <= wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [1926307.279] {client} server      -> wl_display#1.error(object_id: unknown#3, code: 2, message: "abcd")
[INFO] [stderr] [1926307.314] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.325] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.348] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.356] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.363] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.380] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926307.403] {client} server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 30, fd2: 31)
[INFO] [stderr] [1926307.414] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.454] {proxy } client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 18, fd2: 28)
[INFO] [stderr] [1926307.471] {proxy } server      <= wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 18, fd2: 28)
[INFO] [stderr] [1926307.477] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.483] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.550] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926307.565] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stdout] test state::tests::suspend6 ... ok
[INFO] [stdout] test state::tests::display_error ... ok
[INFO] [stdout] test state::tests::closed_client ... ok
[INFO] [stdout] test trans::tests::echo_fd ... ok
[INFO] [stdout] test state::tests::suspend4 ... ok
[INFO] [stdout] test trans::tests::edge_header ... ok
[INFO] [stdout] test trans::tests::array ... ok
[INFO] [stderr] [1926307.575] {server} client#2    -> wlproxy_test#3.echo_fd(echo: wlproxy_test_fd_echo#4, fd1: 29, fd2: 35)
[INFO] [stdout] test trans::tests::fd ... ok
[INFO] [stderr] [1926307.589] {server} client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 29, fd2: 35)
[INFO] [stdout] test trans::tests::large_message ... ok
[INFO] [stderr] [1926307.604] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stdout] test trans::tests::not_word_size ... ok
[INFO] [stderr] [1926307.611] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stdout] test utils::stack::tests::stack ... ok
[INFO] [stderr] [1926307.616] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stdout] test utils::stash::tests::test ... ok
[INFO] [stderr] [1926307.620] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stdout] test object::tests::wrong_downcast - should panic ... ok
[INFO] [stderr] [1926307.682] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926307.684] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1926307.688] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926307.689] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1926307.697] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.698] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.703] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.704] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.710] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.713] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.717] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.721] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.745] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0)
[INFO] [stderr] [1926307.750] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.754] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.757] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.773] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1926307.782] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.800] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1926307.807] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1926307.812] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.817] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926307.869] {proxy } server      -> wlproxy_test_fd_echo#4.fd(fd1: 4, fd2: 29)
[INFO] [stderr] [1926307.873] {proxy } client#2    <= wlproxy_test_fd_echo#4.fd(fd1: 4, fd2: 29)
[INFO] [stderr] [1926307.886] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.892] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.898] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.901] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.904] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.908] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926307.950] {client} server      -> wlproxy_test_fd_echo#4.fd(fd1: 4, fd2: 29)
[INFO] [stderr] [1926307.964] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926307.968] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926307.972] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926308.053] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926308.074] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926308.124] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926308.142] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926308.162] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926308.183] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926308.205] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1926308.210] {client} server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1926308.233] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1926308.245] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1926308.250] {proxy } client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1926308.257] {proxy } server      <= wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1926308.295] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926308.306] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926308.318] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#4)
[INFO] [stderr] [1926308.328] {server} client#2    <= wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [1926308.343] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926308.350] {server} client#2    -> wlproxy_test#3.count_hops(id: wlproxy_test_hops#5)
[INFO] [stderr] [1926308.356] {server} client#2    <= wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [1926308.360] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926308.393] {proxy } server      -> wlproxy_test_hops#4.count(count: 1)
[INFO] [stderr] [1926308.398] {proxy } client#2    <= wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [1926308.425] {client} server      -> wlproxy_test_hops#4.count(count: 2)
[INFO] [stderr] [2026-03-30T09:26:41Z INFO  wl_proxy::state::tests] unsuspend
[INFO] [stderr] [1926308.502] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926308.509] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926308.517] {proxy } server      -> wlproxy_test_hops#5.count(count: 1)
[INFO] [stderr] [1926308.520] {proxy } client#2    <= wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [1926308.542] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926308.548] {client} server      -> wlproxy_test_hops#5.count(count: 2)
[INFO] [stderr] [1926308.939] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01)
[INFO] [stderr] [1926308.951] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1926308.959] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926308.965] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926308.971] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926308.975] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926308.979] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926308.992] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926309.013] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1926309.018] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1926309.020] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926309.024] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.029] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.035] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.038] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.042] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.047] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.069] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01)
[INFO] [stderr] [1926309.074] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.078] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.096] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.115] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1926309.124] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.145] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1926309.153] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1926309.158] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.164] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.186] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102)
[INFO] [stderr] [1926309.193] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1926309.199] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.205] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.213] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.217] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.251] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1926309.255] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1926309.261] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.266] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.272] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.274] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.278] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.283] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.302] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102)
[INFO] [stderr] [1926309.306] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.308] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926309.311] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.314] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.323] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926309.329] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1926309.336] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.338] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926309.354] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1926309.362] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1926309.368] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.370] {client} server      <= wlproxy_test#3.recv_fd(fd: 47)
[INFO] [stderr] [1926309.374] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.376] {client} server      <= wlproxy_test#3.recv_fd(fd: 47)
[INFO] [stderr] [1926309.381] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926309.386] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926309.394] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926309.397] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x010203)
[INFO] [stderr] [1926309.404] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1926309.410] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.416] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.421] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.423] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [1926309.425] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.428] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [1926309.454] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1926309.457] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1926309.463] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.467] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.467] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [1926309.470] {proxy } client#2    -> wlproxy_test#3.recv_fd(fd: 51)
[INFO] [stderr] [1926309.472] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.475] {proxy } server      <= wlproxy_test#3.recv_fd(fd: 51)
[INFO] [stderr] [1926309.475] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.479] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.480] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926309.483] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.494] {proxy } server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926309.500] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x010203)
[INFO] [stderr] [1926309.505] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.511] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.514] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.528] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1926309.531] {server} client#2    -> wlproxy_test#3.recv_fd(fd: 48)
[INFO] [stderr] [1926309.535] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.538] {server} client#2    -> wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [1926309.548] {server} client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926309.551] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1926309.559] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1926309.559] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.564] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.570] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.588] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x01020304)
[INFO] [stderr] [1926309.594] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1926309.600] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.605] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.610] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.614] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.641] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1926309.645] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1926309.650] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.655] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.660] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.662] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.666] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.670] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.687] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x01020304)
[INFO] [stderr] [1926309.692] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.696] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.699] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.712] {client} server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1926309.719] {client} server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.734] {proxy } client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1926309.741] {proxy } server      <= wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1926309.746] {proxy } client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.752] {proxy } server      <= wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.773] {server} client#2    -> wlproxy_test#3.echo_array(echo: wlproxy_test_array_echo#4, array: 0x0102030405)
[INFO] [stderr] [1926309.779] {server} client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1926309.785] {server} client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.791] {server} client#2    -> wl_display#1.sync(callback: wl_callback#5)
[INFO] [stderr] [1926309.795] {server} client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.799] {server} client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.826] {proxy } server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1926309.830] {proxy } client#2    <= wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1926309.843] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.848] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.853] {proxy } server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.856] {proxy } client#2    <= wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.860] {proxy } server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.866] {proxy } client#2    <= wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926309.885] {client} server      -> wlproxy_test_array_echo#4.array(array: 0x0102030405)
[INFO] [stderr] [1926309.889] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926309.894] {client} server      -> wl_callback#5.done(callback_data: 0)
[INFO] [stderr] [1926309.897] {client} server      -> wl_display#1.delete_id(id: 5)
[INFO] [stderr] [1926310.023] {proxy } server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926310.028] {proxy } client#2    <= wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926310.050] {proxy } server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926310.056] {proxy } client#2    <= wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926310.098] {client} server      -> wl_callback#4.done(callback_data: 0)
[INFO] [stderr] [1926310.102] {client} server      -> wl_display#1.delete_id(id: 4)
[INFO] [stderr] [1926310.503] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926310.516] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926310.541] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926310.549] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926310.557] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926310.569] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926310.592] {server} client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926310.601] {server} client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926310.657] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 65535 > 4096
[INFO] [stderr] [1926311.259] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.272] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926311.302] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.311] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.318] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926311.331] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926311.354] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 9 that is not a multiple of 4
[INFO] [stderr] [1926311.940] {client} server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.951] {client} server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926311.975] {proxy } client#2    -> wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.991] {proxy } server      <= wl_display#1.get_registry(registry: wl_registry#2)
[INFO] [stderr] [1926311.997] {proxy } client#2    -> wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926312.008] {proxy } server      <= wl_registry#2.bind(name: 0, id: wlproxy_test#3 (version: 1))
[INFO] [stderr] [1926312.031] {client} server      <= wl_display#1.sync(callback: wl_callback#4)
[INFO] [stderr] [2026-03-30T09:26:41Z ERROR wl_proxy::state] Could not handle client message: could not read a message: message has a supposed length 4 < 8
[INFO] [stdout] test trans::tests::small_message ... ok
[INFO] [stdout] test utils::free_list::tests::test ... ok
[INFO] [stdout] test utils::free_list::tests::release_out_of_bounds - should panic ... ok
[INFO] [stdout] test state::tests::many_events ... ok
[INFO] [stdout] test trans::tests::many_messages_with_fd ... ok
[INFO] [stdout] test trans::tests::many_messages ... ok
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout] 
[INFO] [stdout] ---- acceptor::tests::test stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'acceptor::tests::test' (17) panicked at src/acceptor/tests.rs:9:46:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: AcceptorError(XrdNotSet)
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5a4942fcfb3a - std[ec4e911328de40a6]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5a4942fcfb3a - std[ec4e911328de40a6]::backtrace_rs::backtrace::trace_unsynchronized::<std[ec4e911328de40a6]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5a4942fcfb3a - std[ec4e911328de40a6]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5a4942fcfb3a - <<std[ec4e911328de40a6]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a96a4c5c53f902a3]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5a4942fe7b0a - <core[a96a4c5c53f902a3]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5a4942fe7b0a - core[a96a4c5c53f902a3]::fmt::write
[INFO] [stdout]    6:     0x5a4942fd5b32 - std[ec4e911328de40a6]::io::default_write_fmt::<alloc[c960326de6de28e6]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5a4942fd5b32 - <alloc[c960326de6de28e6]::vec::Vec<u8> as std[ec4e911328de40a6]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5a4942faea9f - <std[ec4e911328de40a6]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5a4942faea9f - std[ec4e911328de40a6]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5a4942fc7f99 - std[ec4e911328de40a6]::panicking::default_hook
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5a4942f5e56c - <alloc[c960326de6de28e6]::boxed::Box<dyn for<'a, 'b> core[a96a4c5c53f902a3]::ops::function::Fn<(&'a std[ec4e911328de40a6]::panic::PanicHookInfo<'b>,), Output = ()> + core[a96a4c5c53f902a3]::marker::Sync + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::Fn<(&std[ec4e911328de40a6]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5a4942f5e56c - test[30c43f9fd66fea90]::test_main_with_exit_callback::<test[30c43f9fd66fea90]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5a4942fc8152 - <alloc[c960326de6de28e6]::boxed::Box<dyn for<'a, 'b> core[a96a4c5c53f902a3]::ops::function::Fn<(&'a std[ec4e911328de40a6]::panic::PanicHookInfo<'b>,), Output = ()> + core[a96a4c5c53f902a3]::marker::Sync + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::Fn<(&std[ec4e911328de40a6]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5a4942fc8152 - std[ec4e911328de40a6]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5a4942faeb58 - std[ec4e911328de40a6]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5a4942fa6449 - std[ec4e911328de40a6]::sys::backtrace::__rust_end_short_backtrace::<std[ec4e911328de40a6]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5a4942faf98d - __rustc[aa69f48705c57ca8]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5a4942fe837c - core[a96a4c5c53f902a3]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5a4942fe80c2 - core[a96a4c5c53f902a3]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5a4942c4640a - <core[a96a4c5c53f902a3]::result::Result<alloc[c960326de6de28e6]::rc::Rc<wl_proxy[5727e424947c2f95]::acceptor::Acceptor>, wl_proxy[5727e424947c2f95]::acceptor::AcceptorError>>::unwrap
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5a4942c4640a - wl_proxy[5727e424947c2f95]::acceptor::tests::test
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:9:46
[INFO] [stdout]   22:     0x5a4942c398a7 - wl_proxy[5727e424947c2f95]::acceptor::tests::test::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/acceptor/tests.rs:8:10
[INFO] [stdout]   23:     0x5a4942c14876 - <wl_proxy[5727e424947c2f95]::acceptor::tests::test::{closure#0} as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5a4942f5264b - <fn() -> core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5a4942f5264b - test[30c43f9fd66fea90]::__rust_begin_short_backtrace::<core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>, fn() -> core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5a4942f5f03b - <core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5a4942f5f03b - std[ec4e911328de40a6]::panicking::catch_unwind::do_call::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>, core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5a4942f5f03b - std[ec4e911328de40a6]::panicking::catch_unwind::<core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>, core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5a4942f5f03b - std[ec4e911328de40a6]::panic::catch_unwind::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>, core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test_in_process
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5a4942f5a754 - test[30c43f9fd66fea90]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5a4942f5a754 - std[ec4e911328de40a6]::sys::backtrace::__rust_begin_short_backtrace::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5a4942f61c42 - std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5a4942f61c42 - <core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5a4942f61c42 - std[ec4e911328de40a6]::panicking::catch_unwind::do_call::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5a4942f61c42 - std[ec4e911328de40a6]::panicking::catch_unwind::<(), core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5a4942f61c42 - std[ec4e911328de40a6]::panic::catch_unwind::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5a4942f61c42 - std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5a4942f61c42 - <std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1} as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5a4942fcf44f - <alloc[c960326de6de28e6]::boxed::Box<dyn core[a96a4c5c53f902a3]::ops::function::FnOnce<(), Output = ()> + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5a4942fcf44f - <std[ec4e911328de40a6]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7e52bb889aa4 - <unknown>
[INFO] [stdout]   45:     0x7e52bb916a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] ---- state::tests::acceptor stdout ----
[INFO] [stdout] 
[INFO] [stdout] thread 'state::tests::acceptor' (130) panicked at src/state/tests.rs:114:49:
[INFO] [stdout] called `Result::unwrap()` on an `Err` value: StateError(CreateAcceptor(AcceptorError(XrdNotSet)))
[INFO] [stdout] stack backtrace:
[INFO] [stdout]    0:     0x5a4942fcfb3a - std[ec4e911328de40a6]::backtrace_rs::backtrace::libunwind::trace
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/../../backtrace/src/backtrace/libunwind.rs:117:9
[INFO] [stdout]    1:     0x5a4942fcfb3a - std[ec4e911328de40a6]::backtrace_rs::backtrace::trace_unsynchronized::<std[ec4e911328de40a6]::sys::backtrace::_print_fmt::{closure#1}>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/../../backtrace/src/backtrace/mod.rs:66:14
[INFO] [stdout]    2:     0x5a4942fcfb3a - std[ec4e911328de40a6]::sys::backtrace::_print_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:74:9
[INFO] [stdout]    3:     0x5a4942fcfb3a - <<std[ec4e911328de40a6]::sys::backtrace::BacktraceLock>::print::DisplayBacktrace as core[a96a4c5c53f902a3]::fmt::Display>::fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:44:26
[INFO] [stdout]    4:     0x5a4942fe7b0a - <core[a96a4c5c53f902a3]::fmt::rt::Argument>::fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/fmt/rt.rs:152:76
[INFO] [stdout]    5:     0x5a4942fe7b0a - core[a96a4c5c53f902a3]::fmt::write
[INFO] [stdout]    6:     0x5a4942fd5b32 - std[ec4e911328de40a6]::io::default_write_fmt::<alloc[c960326de6de28e6]::vec::Vec<u8>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/io/mod.rs:639:11
[INFO] [stdout]    7:     0x5a4942fd5b32 - <alloc[c960326de6de28e6]::vec::Vec<u8> as std[ec4e911328de40a6]::io::Write>::write_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/io/mod.rs:1994:13
[INFO] [stdout]    8:     0x5a4942faea9f - <std[ec4e911328de40a6]::sys::backtrace::BacktraceLock>::print
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:47:9
[INFO] [stdout]    9:     0x5a4942faea9f - std[ec4e911328de40a6]::panicking::default_hook::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:292:27
[INFO] [stdout]   10:     0x5a4942fc7f99 - std[ec4e911328de40a6]::panicking::default_hook
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:316:9
[INFO] [stdout]   11:     0x5a4942f5e56c - <alloc[c960326de6de28e6]::boxed::Box<dyn for<'a, 'b> core[a96a4c5c53f902a3]::ops::function::Fn<(&'a std[ec4e911328de40a6]::panic::PanicHookInfo<'b>,), Output = ()> + core[a96a4c5c53f902a3]::marker::Sync + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::Fn<(&std[ec4e911328de40a6]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   12:     0x5a4942f5e56c - test[30c43f9fd66fea90]::test_main_with_exit_callback::<test[30c43f9fd66fea90]::test_main::{closure#0}>::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:145:21
[INFO] [stdout]   13:     0x5a4942fc8152 - <alloc[c960326de6de28e6]::boxed::Box<dyn for<'a, 'b> core[a96a4c5c53f902a3]::ops::function::Fn<(&'a std[ec4e911328de40a6]::panic::PanicHookInfo<'b>,), Output = ()> + core[a96a4c5c53f902a3]::marker::Sync + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::Fn<(&std[ec4e911328de40a6]::panic::PanicHookInfo,)>>::call
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2254:9
[INFO] [stdout]   14:     0x5a4942fc8152 - std[ec4e911328de40a6]::panicking::panic_with_hook
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:833:13
[INFO] [stdout]   15:     0x5a4942faeb58 - std[ec4e911328de40a6]::panicking::panic_handler::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:698:13
[INFO] [stdout]   16:     0x5a4942fa6449 - std[ec4e911328de40a6]::sys::backtrace::__rust_end_short_backtrace::<std[ec4e911328de40a6]::panicking::panic_handler::{closure#0}, !>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:182:18
[INFO] [stdout]   17:     0x5a4942faf98d - __rustc[aa69f48705c57ca8]::rust_begin_unwind
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:689:5
[INFO] [stdout]   18:     0x5a4942fe837c - core[a96a4c5c53f902a3]::panicking::panic_fmt
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panicking.rs:80:14
[INFO] [stdout]   19:     0x5a4942fe80c2 - core[a96a4c5c53f902a3]::result::unwrap_failed
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/result.rs:1867:5
[INFO] [stdout]   20:     0x5a4942c4020f - <core[a96a4c5c53f902a3]::result::Result<alloc[c960326de6de28e6]::rc::Rc<wl_proxy[5727e424947c2f95]::acceptor::Acceptor>, wl_proxy[5727e424947c2f95]::state::StateError>>::unwrap
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/result.rs:1233:23
[INFO] [stdout]   21:     0x5a4942c4020f - wl_proxy[5727e424947c2f95]::state::tests::acceptor
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:114:49
[INFO] [stdout]   22:     0x5a4942c391b7 - wl_proxy[5727e424947c2f95]::state::tests::acceptor::{closure#0}
[INFO] [stdout]                                at /opt/rustwide/workdir/src/state/tests.rs:99:14
[INFO] [stdout]   23:     0x5a4942c13e36 - <wl_proxy[5727e424947c2f95]::state::tests::acceptor::{closure#0} as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   24:     0x5a4942f5264b - <fn() -> core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   25:     0x5a4942f5264b - test[30c43f9fd66fea90]::__rust_begin_short_backtrace::<core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>, fn() -> core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:663:18
[INFO] [stdout]   26:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test_in_process::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:686:74
[INFO] [stdout]   27:     0x5a4942f5f03b - <core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   28:     0x5a4942f5f03b - std[ec4e911328de40a6]::panicking::catch_unwind::do_call::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>, core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:581:40
[INFO] [stdout]   29:     0x5a4942f5f03b - std[ec4e911328de40a6]::panicking::catch_unwind::<core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>, core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:544:19
[INFO] [stdout]   30:     0x5a4942f5f03b - std[ec4e911328de40a6]::panic::catch_unwind::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<test[30c43f9fd66fea90]::run_test_in_process::{closure#0}>, core[a96a4c5c53f902a3]::result::Result<(), alloc[c960326de6de28e6]::string::String>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panic.rs:359:14
[INFO] [stdout]   31:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test_in_process
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:686:27
[INFO] [stdout]   32:     0x5a4942f5f03b - test[30c43f9fd66fea90]::run_test::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:607:43
[INFO] [stdout]   33:     0x5a4942f5a754 - test[30c43f9fd66fea90]::run_test::{closure#1}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/test/src/lib.rs:637:41
[INFO] [stdout]   34:     0x5a4942f5a754 - std[ec4e911328de40a6]::sys::backtrace::__rust_begin_short_backtrace::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/backtrace.rs:166:18
[INFO] [stdout]   35:     0x5a4942f61c42 - std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/thread/lifecycle.rs:91:13
[INFO] [stdout]   36:     0x5a4942f61c42 - <core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/panic/unwind_safe.rs:275:9
[INFO] [stdout]   37:     0x5a4942f61c42 - std[ec4e911328de40a6]::panicking::catch_unwind::do_call::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:581:40
[INFO] [stdout]   38:     0x5a4942f61c42 - std[ec4e911328de40a6]::panicking::catch_unwind::<(), core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panicking.rs:544:19
[INFO] [stdout]   39:     0x5a4942f61c42 - std[ec4e911328de40a6]::panic::catch_unwind::<core[a96a4c5c53f902a3]::panic::unwind_safe::AssertUnwindSafe<std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}::{closure#0}>, ()>
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/panic.rs:359:14
[INFO] [stdout]   40:     0x5a4942f61c42 - std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked::<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/thread/lifecycle.rs:89:26
[INFO] [stdout]   41:     0x5a4942f61c42 - <std[ec4e911328de40a6]::thread::lifecycle::spawn_unchecked<test[30c43f9fd66fea90]::run_test::{closure#1}, ()>::{closure#1} as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once::{shim:vtable#0}
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/core/src/ops/function.rs:250:5
[INFO] [stdout]   42:     0x5a4942fcf44f - <alloc[c960326de6de28e6]::boxed::Box<dyn core[a96a4c5c53f902a3]::ops::function::FnOnce<(), Output = ()> + core[a96a4c5c53f902a3]::marker::Send> as core[a96a4c5c53f902a3]::ops::function::FnOnce<()>>::call_once
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/alloc/src/boxed.rs:2240:9
[INFO] [stdout]   43:     0x5a4942fcf44f - <std[ec4e911328de40a6]::sys::thread::unix::Thread>::new::thread_start
[INFO] [stdout]                                at /rustc/0abe69e6c16114311cc2700e972492e64d69c28f/library/std/src/sys/thread/unix.rs:118:17
[INFO] [stdout]   44:     0x7e52bb889aa4 - <unknown>
[INFO] [stdout]   45:     0x7e52bb916a64 - clone
[INFO] [stdout]   46:                0x0 - <unknown>
[INFO] [stdout] 
[INFO] [stdout] 
[INFO] [stdout] failures:
[INFO] [stdout]     acceptor::tests::test
[INFO] [stdout]     state::tests::acceptor
[INFO] [stdout] 
[INFO] [stdout] test result: FAILED. 109 passed; 2 failed; 0 ignored; 0 measured; 0 filtered out; finished in 3.01s
[INFO] [stdout] 
[INFO] [stderr] error: test failed, to rerun pass `--lib`
[INFO] running `Command { std: "docker" "inspect" "bce7c03ef4aec8bb858e756ed0a6d4abee44eed34644fc4243328a5c8e506ea1", kill_on_drop: false }`
[INFO] running `Command { std: "docker" "rm" "-f" "bce7c03ef4aec8bb858e756ed0a6d4abee44eed34644fc4243328a5c8e506ea1", kill_on_drop: false }`
[INFO] [stdout] bce7c03ef4aec8bb858e756ed0a6d4abee44eed34644fc4243328a5c8e506ea1
